daslang: -log-compile-time CLI flag for per-module compile diagnostics by borisbat · Pull Request #2680 · GaijinEntertainment/daScript

borisbat · 2026-05-16T05:50:30Z

Summary

Adds a new -log-compile-time CLI flag on the daslang executable, mapped to a new CodeOfPolicies::log_module_compile_time field. When set, every required module emits its own parse / infer (with pass count) / optimize / macro (in infer) / macro mods breakdown plus its function count, every Program::simulate invocation (macro modules during compile + the final entry-point simulate) logs its elapsed time with the owning module name, and the top-level aggregate summary fires regardless.

Motivating use case: daspkg install dasimgui globally, then run a require dasimgui driver under -log-compile-time to see which submodules dominate compile time.

The existing log_compile_time (per-file one-liner) option is unchanged. log_total_compile_time shares the new format (label + function count + clarified macro (in infer) wording); confirmed with the repo owner this is not consumed by any tooling.

Changed pieces

Policy + Program member (include/daScript/ast/ast.h): new /*option*/ bool log_module_compile_time next to the existing log-time options; new int Program::inferPassesUsed to surface the sum of inferTypesDirty inner-loop passes.
Infer counter (src/ast/ast_infer_type.cpp): Program::inferTypes resets inferPassesUsed = 0; Program::inferTypesDirty adds its local pass value at the end of each invocation. Result is the total number of times the inner type-inference loop ran for this module, across all macro-driven re-infer cycles.
Per-module log (src/ast/ast_parse.cpp): local accumulators myParseT / myInferT / myOptT / myMacroModT capture per-phase deltas alongside the existing accumulation into *totParse / etc.; the per-file log block at the end of parseDaScript emits the breakdown when the new policy is on. Gated on isDep — the entry script's per-module log is suppressed because its post-parseDaScript work (markExecutableSymbolUse/removeUnusedSymbols/deriveAliases/allocateStack/validateAst) runs in compileDaScript, so the top-level summary is authoritative for it.
Top-level summary (src/ast/ast_parse.cpp): now reads total compile took X, fileName -- N functions followed by require / parse / infer / optimize / macro (in infer) / macro mods lines. Fires on either log_total_compile_time or log_module_compile_time.
Simulate log (src/ast/ast_simulate.cpp): existing simulate-time line now also fires on the new policy. When thisModule->name is non-empty, prints , modName (fileName); when empty (the entry script), prints , fileName plain. No noisy double-space.
RTTI registration (src/builtin/module_builtin_rtti.cpp): registers log_module_compile_time so for_each_field (used by daslib/rst.das and das2rst) sees it.
CLI wiring (utils/daScript/main.cpp): file-scope static logModuleCompileTime, -log-compile-time argv branch, policies wiring at BOTH getPolicies() (AOT path) and compile_and_run (run path), help-text line.
Docs: row in doc/source/reference/language/options.rst options table; description line in doc/source/stdlib/handmade/structure_annotation-rtti-CodeOfPolicies.rst.
Drive-by doc fix: the handmade CodeOfPolicies description file was already missing a description for max_call_depth, which silently shifted ~30 later field descriptions up by one in the generated rtti.rst. Added the missing line in the same commit since I touched the file anyway.
Mouse cards: 3 new cards for the gotchas discovered while doing this work (CodeOfPolicies-field full checklist, the das2rst handmade positional-mapping + silent-shift trap, daslang CLI flag wiring), plus a JSON-cast card carried over from a prior session.

Sample output (current format)

Running bin/daslang -log-compile-time -dry-run examples/imgui_demo/main.das (full ImGui demo, ~80 required modules):

Top consumers (sorted by wall-clock; one block per required module):

compiler took 0.955092, widgets (.../examples/imgui_demo/widgets.das) -- 1924 functions
        parse    0.001137
        infer    0.859151 (57 passes)
        optimize 0.063853
        macro (in infer) 0.148901
        macro mods 0
compiler took 0.553832, imgui_widgets_builtin (.../widgets/imgui_widgets_builtin.das) -- 762 functions
        parse    0.003384
        infer    0.489309 (45 passes)
        optimize 0.043283
        macro (in infer) 0.272757
        macro mods 0
...
total compile took 4.281755, .../examples/imgui_demo/main.das -- 6296 functions
        require  ...
        parse    ...
        infer    ...
        optimize ...
        macro (in infer) ...
        macro mods ...
simulate (including init script) took 0.124550, .../examples/imgui_demo/main.das

And on a no-module entry script (examples/hello_world.das):

total compile took 0.00157, examples/hello_world.das -- 1 functions
        require  ...
        parse    ...
        ...
simulate (including init script) took 3.3e-05, examples/hello_world.das

(No , (...) noise when module name is empty — handled at both the simulate line and the per-module log via the isDep gate.)

Test plan

🤖 Generated with Claude Code

Copilot

Pull request overview

Adds a new daslang CLI flag (-log-compile-time) and corresponding CodeOfPolicies::log_module_compile_time option to emit per-module compile diagnostics (phase breakdown + simulate timing), including surfacing the macro-driven type-inference pass count.

Changes:

Introduces log_module_compile_time as a CodeOfPolicies option and wires it through daslang CLI parsing and policy construction.
Adds per-module timing breakdown logging in parsing/compilation and expands simulate-time logging to include module identity.
Updates RTTI registration and documentation so the new policy/option is visible and described (plus a fix to CodeOfPolicies handmade docs alignment).

Reviewed changes

Copilot reviewed 12 out of 12 changed files in this pull request and generated 5 comments.

Show a summary per file

File	Description
utils/daScript/main.cpp	Adds `-log-compile-time` flag, help text, and maps it into `CodeOfPolicies`.
include/daScript/ast/ast.h	Adds `CodeOfPolicies::log_module_compile_time` and `Program::inferPassesUsed`.
src/ast/ast_infer_type.cpp	Records `inferPassesUsed` after the outer macro-driven inference loop.
src/ast/ast_parse.cpp	Collects per-module phase timings and emits per-module compile breakdown when enabled; extends top-level summary gating.
src/ast/ast_simulate.cpp	Enables simulate timing logs for the new option and includes module name + file in output.
src/builtin/module_builtin_rtti.cpp	Registers `log_module_compile_time` for RTTI/`for_each_field` visibility.
doc/source/reference/language/options.rst	Documents the new `log_module_compile_time` option.
doc/source/stdlib/handmade/structure_annotation-rtti-CodeOfPolicies.rst	Adds missing `max_call_depth` description line and documents the new policy field.
mouse-data/docs/*.md	Adds new “mouse cards” documenting related gotchas and workflows.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Copilot

Pull request overview

Copilot reviewed 12 out of 12 changed files in this pull request and generated 2 comments.

Comments suppressed due to low confidence (2)

src/ast/ast_infer_type.cpp:5752

inferPassesUsed is described as an “outer macro-driven pass count”, but it’s currently accumulated from the inner inferTypesDirty loop variable (pass) and uses the 0-based index value at loop exit. This can undercount (e.g. a single successful infer pass can record 0) and may not match the intended “# of infer cycles due to macros” reported by Program::inferTypes’ own pass loop. Consider either (1) recording the outer Program::inferTypes pass count explicitly, or (2) renaming/commenting the field and adjusting the math to reflect the actual number of infer iterations executed.

This issue also appears on line 5884 of the same file.

    void Program::inferTypes(TextWriter &logs, ModuleGroup &libGroup) {
        newLambdaIndex = 1;
        inferPassesUsed = 0;   // accumulated by inferTypesDirty across all calls
        inferTypesDirty(logs, false);
        bool anyMacrosDidWork = false;
        bool anyMacrosFailedToInfer = false;
        int pass = 0;
        int32_t maxInferPasses = options.getIntOption("max_infer_passes", policies.max_infer_passes);

src/ast/ast_infer_type.cpp:5891

inferPassesUsed += pass uses pass as a 0-based iteration index when the loop breaks via context.finished(), which can record 0 even though one inference iteration ran. If this value is meant to be user-facing in the compile-time logs, it should reflect the actual number of passes executed (usually pass + 1 for the context.finished() break path), or be computed from a dedicated counter.

        if (pass == maxInferPasses) {
            error("type inference exceeded maximum allowed number of passes (" + to_string(maxInferPasses) + ")\n"
                                                                                                             "this is likely due to a loop in the type system",
                  "", "",
                  LineInfo(), CompilationError::exceeds_infer_passes);
        }
        inferPassesUsed += pass;   // accumulate inner-loop passes across all inferTypesDirty calls in this module
    }

Copilot

Pull request overview

Copilot reviewed 12 out of 12 changed files in this pull request and generated 4 comments.

Copilot

Pull request overview

Copilot reviewed 12 out of 12 changed files in this pull request and generated 1 comment.

Copilot

Pull request overview

Copilot reviewed 12 out of 12 changed files in this pull request and generated 5 comments.

Adds new CLI flag and CodeOfPolicies::log_module_compile_time field that emits a per-module compile-time breakdown (parse / infer + pass count / optimize / macro / macro-mods) for every required module, plus a simulate-time line with the owning module name. Useful for diagnosing which submodule dominates compile time on large module graphs (motivating case: profiling a daspkg-installed dasImgui). - include/daScript/ast/ast.h: new policy field + Program::inferPassesUsed - src/ast/ast_infer_type.cpp: record outer macro pass count after inferTypes loop - src/ast/ast_parse.cpp: per-phase local accumulators in parseDaScript; new per-module breakdown log; extend top-level summary gate - src/ast/ast_simulate.cpp: simulate hook now logs module name and fires on either log_total_compile_time or log_module_compile_time - src/builtin/module_builtin_rtti.cpp: register log_module_compile_time for RTTI so daslib/rst.das + das2rst see the field - utils/daScript/main.cpp: -log-compile-time argv + policies wiring (both getPolicies() and compile_and_run paths) + help text - doc/source/stdlib/handmade/structure_annotation-rtti-CodeOfPolicies.rst: add description for the new field; also fix a pre-existing missing description for max_call_depth that was silently shifting ~30 later field descriptions up by one in generated/rtti.rst - doc/source/reference/language/options.rst: row in options table - mouse-data/docs/: 3 new cards for the discoveries during this work (CodeOfPolicies-field full checklist, das2rst handmade positional mapping + silent-shift trap, daslang CLI flag wiring), plus a carryover JSON-cast card from a prior session Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>

Copilot